Skip to content

Implement Dialog Event subscription (client only)#3754

Merged
sauwming merged 20 commits intopjsip:masterfrom
goodicus:busy_lamp_field
Jan 29, 2024
Merged

Implement Dialog Event subscription (client only)#3754
sauwming merged 20 commits intopjsip:masterfrom
goodicus:busy_lamp_field

Conversation

@goodicus
Copy link
Copy Markdown
Contributor

@goodicus goodicus commented Nov 1, 2023

Implement Dialog Event subscription (client only) for dialog monitoring purpose, which can be useful for features such as BLF (Busy Lamp Field) that displays the state of the calls associated with the Sip extension.

The most important RFCs related to this are:

  • 3856 - A Presence Event Package for Session Initiation Protocol (SIP)
  • 4235 - An INVITE-Initiated Dialog Event Package for the Session Initialisation Protocol (SIP)

Implement busy line field implementation
@CLAassistant
Copy link
Copy Markdown

CLAassistant commented Nov 1, 2023

CLA assistant check
All committers have signed the CLA.

@goodicus goodicus marked this pull request as ready for review November 1, 2023 11:05
@sauwming sauwming added this to the release-2.15 milestone Nov 2, 2023
@sauwming
Copy link
Copy Markdown
Member

sauwming commented Nov 2, 2023

This is a rather extensive PR, so we may need some time to review it.
A couple of notes:

  • CLA not yet signed
  • Build failure.

Oleksandr-Goodicus and others added 2 commits November 3, 2023 11:33
Without deletion {} in "struct pjdialog_info_op_desc pjdialog_info_op" compiler fails wiht error C2078.
@goodicus
Copy link
Copy Markdown
Contributor Author

goodicus commented Nov 7, 2023

Hi @sauwming!
I can explain the feature details if it's helpful.

@sauwming
Copy link
Copy Markdown
Member

Thank you for the patch, appreciate it. Coincidentally, there are some of our users who recently inquired about this feature, so this could be useful.

I tried it here and have to fix adding the declaration of pjsua_buddy_del_blf() in pjsua.h to get it working, but that's minor. Then I tried pjsua_app, and sent SUBSCRIBE using +d, but it always failed with: SIP/2.0 489 Bad Event. Not sure what went wrong there.

So I guess what's missing here are some test scenarios for us to verify that the offered features and functionalities are indeed working as expected. For example:
scenario A-subscribe: 1. initialise by ..., 2. subscribe using ..., 3. verify that you receive the message ....
scenario B-unsubscribe: 2. unsubscribe 2. verify that it works by checking ....
etc
scenario C-update: ....

@goodicus
Copy link
Copy Markdown
Contributor Author

goodicus commented Dec 28, 2023

Hi @sauwming!
You mentioned about "489 Bad Event". Could you, please, provide some details about PBX, its configuration and logs?
If Asterisk is used, adjust the configuration according to the next guidance http://www.corecomputance.jp/user_manuals/gxp2000_interop_asterisk_blf.pdf

| sleep MS echo [0|1|txt] |
+=============================================================================+
You have 0 active call
>>> +d
Enter buddy's URI: (empty to cancel): sip:123001@192.168.1.99

Enter buddy's URI: (empty to cancel): sip:123001@192.168.1.99
17:03:12.615 pjsua_pres.c !Adding buddy: sip:123001@192.168.1.99
17:03:12.615 pjsua_pres.c .Buddy 1 added.
17:03:12.615 pjsua_pres.c .Buddy 1: unsubscribing blf..
17:03:12.615 pjsua_pres.c ..Buddy 1: updating blf..
17:03:12.616 pjsua_pres.c ...Buddy 1: subscribing blf,using account 1..
17:03:12.616 pjsua_core.c ......TX 638 bytes Request msg SUBSCRIBE/cseq=7537 (tdta0x5612de72b258) to UDP 192.168.1.99:5060:
SUBSCRIBE sip:123001@192.168.1.99 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.23:5098;rport;branch=z9hG4bKPj9886f3d5-96c4-4f35-96e3-36c77c3a6a9f
Max-Forwards: 70
From: sip:123001@192.168.1.99;tag=026dec20-8ab3-4c63-bb96-68fa3e39ba3f
To: sip:123001@192.168.1.99
Contact: sip:123001@192.168.1.23:5098;ob
Call-ID: b08b7cd6-faeb-464c-9223-e39c9f5f6c72
CSeq: 7537 SUBSCRIBE
Event: dialog
Expires: 600
Supported: replaces, 100rel, timer, norefersub, trickle-ice
Accept: application/dialog-info+xml
Allow-Events: presence, dialog, message-summary, refer
User-Agent: PJSUA v2.14-dev Linux-5.15.0.91/x86_64/glibc-2.31
Content-Length: 0

--end msg--
17:03:12.616 evsub0x5612de6d8c38 ........Subscription state changed NULL --> SENT
17:03:12.616 pjsua_pres.c .........BLF subscription to sip:123001@192.168.1.99 is SENT
17:03:12.616 pjsua_app.c ..........Buddy 1: blf subscription state: SENT (event: TSX_STATE)
17:03:12.616 pjsua_app.c ..........sip:123001@192.168.1.99 dialog-info-state: , dialog-info-entity: , dialog-id: , dialog-call-id: , dialog-remote-tag: , dialog-local-tag: , dialog-direction: , dialog-state: NULL, dialog-duration: , local-identity: , local-target-uri: , remote-identity: , remote-target-uri: , subscription blf state: SENT, (last termination reason code=0 )
New buddy 'sip:123001@192.168.1.99' added at index 2
>>> 17:03:12.697 pjsua_core.c .RX 458 bytes Response msg 401/SUBSCRIBE/cseq=7537 (rdata0x7f3af400a048) from UDP 192.168.1.99:5060:
SIP/2.0 401 Unauthorized
Via: SIP/2.0/UDP 192.168.1.23:5098;rport=5098;branch=z9hG4bKPj9886f3d5-96c4-4f35-96e3-36c77c3a6a9f
To: sip:123001@192.168.1.99;tag=41650d1b
From: sip:123001@192.168.1.99;tag=026dec20-8ab3-4c63-bb96-68fa3e39ba3f
Call-ID: b08b7cd6-faeb-464c-9223-e39c9f5f6c72
CSeq: 7537 SUBSCRIBE
WWW-Authenticate: Digest nonce="1703775792:b24c99f152189853e50530022ed277ec6b5d643b",algorithm=MD5,realm="asterisk"
Content-Length: 0

--end msg--
17:03:12.698 sip_auth_client.c ....Digest algorithm is "MD5"
17:03:12.698 pjsua_core.c ......TX 858 bytes Request msg SUBSCRIBE/cseq=7538 (tdta0x5612de72b258) to UDP 192.168.1.99:5060:
SUBSCRIBE sip:123001@192.168.1.99 SIP/2.0
Via: SIP/2.0/UDP 192.168.1.23:5098;rport;branch=z9hG4bKPj6a34d221-006c-4b98-a465-89703ae8b696
Max-Forwards: 70
From: sip:123001@192.168.1.99;tag=026dec20-8ab3-4c63-bb96-68fa3e39ba3f
To: sip:123001@192.168.1.99
Contact: sip:123001@192.168.1.23:5098;ob
Call-ID: b08b7cd6-faeb-464c-9223-e39c9f5f6c72
CSeq: 7538 SUBSCRIBE
Event: dialog
Expires: 600
Supported: replaces, 100rel, timer, norefersub, trickle-ice
Accept: application/dialog-info+xml
Allow-Events: presence, dialog, message-summary, refer
User-Agent: PJSUA v2.14-dev Linux-5.15.0.91/x86_64/glibc-2.31
Authorization: Digest username="123001", realm="asterisk", nonce="1703775792:b24c99f152189853e50530022ed277ec6b5d643b", uri="sip:123001@192.168.1.99", response="e52962fde2c7e5b9edb9d5e35c9f2cfc", algorithm=MD5
Content-Length: 0

--end msg--
17:03:12.804 pjsua_core.c .RX 755 bytes Request msg NOTIFY/cseq=2 (rdata0x7f3af400a048) from UDP 192.168.1.99:5060:
NOTIFY sip:123001@192.168.1.23:5098;ob SIP/2.0
Via: SIP/2.0/UDP 192.168.1.99:5060;branch=z9hG4bK-524287-1---e2953c5f;rport
Via: SIP/2.0/UDP 192.168.1.91:5066;branch=z9hG4bK-524287-1---e102555699b0bc5f;rport=5066
Max-Forwards: 69
Contact: sip:123001@192.168.1.91:5066
To: sip:123001@192.168.1.99;tag=026dec20-8ab3-4c63-bb96-68fa3e39ba3f
From: sip:123001@192.168.1.99;tag=4ac8d342
Call-ID: b08b7cd6-faeb-464c-9223-e39c9f5f6c72
CSeq: 2 NOTIFY
Content-Type: application/dialog-info+xml
Subscription-State: active;expires=600
Event: dialog
Content-Length: 179

--end msg--
17:03:12.804 pjsua_core.c .......TX 616 bytes Response msg 200/NOTIFY/cseq=2 (tdta0x7f3af400c018) to UDP 192.168.1.99:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.99:5060;rport=5060;received=192.168.1.99;branch=z9hG4bK-524287-1---e2953c5f
Via: SIP/2.0/UDP 192.168.1.91:5066;rport=5066;branch=z9hG4bK-524287-1---e102555699b0bc5f
Call-ID: b08b7cd6-faeb-464c-9223-e39c9f5f6c72
From: sip:123001@192.168.1.99;tag=4ac8d342
To: sip:123001@192.168.1.99;tag=026dec20-8ab3-4c63-bb96-68fa3e39ba3f
CSeq: 2 NOTIFY
Contact: sip:123001@192.168.1.23:5098;ob
Allow: PRACK, INVITE, ACK, BYE, CANCEL, UPDATE, INFO, SUBSCRIBE, NOTIFY, REFER, MESSAGE, OPTIONS
Supported: replaces, 100rel, timer, norefersub, trickle-ice
Content-Length: 0

--end msg--
17:03:12.804 evsub0x5612de6d8c38 .....Subscription state changed SENT --> ACTIVE
17:03:12.804 pjsua_pres.c ......BLF subscription to sip:123001@192.168.1.99 is ACTIVE
17:03:12.804 pjsua_app.c .......Buddy 1: blf subscription state: ACTIVE (event: TSX_STATE (RX Request msg NOTIFY/cseq=2 (rdata0x7f3af400a048)))
17:03:12.804 pjsua_app.c .......sip:123001@192.168.1.99 dialog-info-state: full, dialog-info-entity: sip:123001@192.168.1.99:5060, dialog-id: , dialog-call-id: , dialog-remote-tag: , dialog-local-tag: , dialog-direction: , dialog-state: NULL, dialog-duration: , local-identity: , local-target-uri: , remote-identity: , remote-target-uri: , subscription blf state: ACTIVE, (last termination reason code=0 )
17:03:12.804 pjsua_core.c .RX 466 bytes Response msg 200/SUBSCRIBE/cseq=7538 (rdata0x7f3af400a048) from UDP 192.168.1.99:5060:
SIP/2.0 200 OK
Via: SIP/2.0/UDP 192.168.1.23:5098;rport=5098;branch=z9hG4bKPj6a34d221-006c-4b98-a465-89703ae8b696
Record-Route: sip:192.168.1.99;lr;ep;pinhole=UDP:192.168.1.23:5098;ipnt=8j0_zu0op92
Contact: sip:123001@192.168.1.91:5066
To: sip:123001@192.168.1.99;tag=4ac8d342
From: sip:123001@192.168.1.99;tag=026dec20-8ab3-4c63-bb96-68fa3e39ba3f
Call-ID: b08b7cd6-faeb-464c-9223-e39c9f5f6c72
CSeq: 7538 SUBSCRIBE
Expires: 600
Content-Length: 0

--end msg--

@sauwming
Copy link
Copy Markdown
Member

sauwming commented Jan 2, 2024

I am using Kamailio for testing and after following https://kb.asipto.com/kamailio:presence:k43-blf, now it can work correctly. Thx for the pointer.

13:53:34.055            pjsua_app.c  ......Buddy 5: blf subscription state: ACCEPTED (event: TSX_STATE (RX Response msg 202/SUBSCRIBE/cseq=16501 (rdata0x109a9d928)))
13:53:34.055            pjsua_app.c  ......sip:402@sip.pjsip.org dialog-info-state: , dialog-info-entity: , dialog-id: , dialog-call-id: , dialog-remote-tag: , dialog-local-tag: , dialog-direction: , dialog-state: NULL, dialog-duration: , local-identity: , local-target-uri: , remote-identity: , remote-target-uri: , subscription blf state: ACCEPTED, (last termination reason code=0 )

@sauwming sauwming changed the title Implement a busy line field feature Implement a busy lamp field feature Jan 2, 2024
* Add callbacks description.
* Sort includes alphabetically.
* Apply stylistic formating.
@sauwming
Copy link
Copy Markdown
Member

sauwming commented Jan 8, 2024

To update you, we will review this during our internal team meeting next week.
After rechecking everything though, in my view, it may not be feasible for us to integrate this due to the lack of RFC. Still, I would raise this PR with the rest of our team and update you again.

Note: the Windows build failed.

@goodicus
Copy link
Copy Markdown
Contributor Author

goodicus commented Jan 8, 2024

@sauwming Thanks for your feedback.
I fixed the Windows build.
But it is painful to hear that such a valuable and expected PR could be ignored. The question is what do you mean about lack of RFC?

@sauwming
Copy link
Copy Markdown
Member

sauwming commented Jan 9, 2024

I was referring to your description which mentions that there is not a specific RFC dedicated to the Busy Lamp Field (BLF), and that the actual implementation of BLF can vary between different VoIP systems and devices.

@sauwming
Copy link
Copy Markdown
Member

I previously tested it using --add-buddy option, and it looks like the behaviour is different compared to using +b. I have modified it in the latest commit.

@goodicus
Copy link
Copy Markdown
Contributor Author

Hi @sauwming!
The changes are acceptable except for one logging change. This function printed out valuable different debug info.
32ce7f0

@goodicus
Copy link
Copy Markdown
Contributor Author

@sauwming Everything is fine for me.
Let's merge!

@sauwming
Copy link
Copy Markdown
Member

I still can't test this past the initial SUBSCRIBE.

Since this doesn't have any server implementation, I tried testing against various other SIP phones such as Linphone, Zoiper, but so far I had no luck.

Comment on lines +278 to +284
if (dlgev->tmp_status._is_valid) {
PJ_ASSERT_RETURN(dlgev->tmp_pool!=NULL, PJSIP_SIMPLE_ENOPRESENCE);
pj_memcpy(status, &dlgev->tmp_status, sizeof(pjsip_dlg_event_status));
} else {
PJ_ASSERT_RETURN(dlgev->status_pool!=NULL, PJSIP_SIMPLE_ENOPRESENCE);
pj_memcpy(status, &dlgev->status, sizeof(pjsip_dlg_event_status));
}
Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Protect access to dlgev states with lock?

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I have modified everything except these two.
Note that the code here is copied from presence, so if it requires lock here, it probably needs one there too, and both don't have their own lock at the moment.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

This is one possible race condition scenario:

  1. Thread 1: executes pjsip_dlg_event_get_status(), dlgev->tmp_status._is_valid is evaluated as true, but before memcpy(status, tmp_status, ..), context switch happens.
  2. Thread 2: executes dlg_event_process_rx_notify() in this line:
    dlgev->tmp_status._is_valid = PJ_FALSE;
    pj_pool_reset(dlgev->tmp_pool);
    
  3. Back to Thread 1: it copies from dlgev->tmp_status whose pool has just been reset (not swapped due to p_st_code is not 2xx).

This may be a corner case as usually NOTIFY will be responded with 200.

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

OK, so how do we proceed here? I only add lock for dlg event and create the fix for presence in a separate PR?

Copy link
Copy Markdown
Member

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Yes, I think so.

@sauwming
Copy link
Copy Markdown
Member

Modifications in the latest commit:

  • Add mutex
  • Change based on comments (Move internal flag _is_valid and fix _is_valid setting)
  • Fix assertion and crash during testing.
    Due to the lack of dialog event server APIs to send NOTIFY for dialog state change, I use SIPP script attached.
    uas-subscribe.xml.txt
    There were a couple of problems discovered:
    • Assertion if dialog info doesn't contain certain attributes or elements.
      This should not happen as the dialog info is sent by the remote and we have no control over its completeness.
    • Crash during resubscription scenario, because the previous buddy->dlg_evstatus was not cleared.
11:26:24.129            pjsua_app.c  .........Buddy 0: dialog event subscription state: SENT (event: TSX_STATE)
=================================================================
==43988==ERROR: AddressSanitizer: heap-use-after-free on address 0x0001094166b0 at pc 0x0001061c51c0 bp 0x00016bd0a6f0 sp 0x00016bd09ea0
READ of size 4 at 0x0001094166b0 thread T4

    #0 0x1061c51bc in __asan_memcpy+0x394 (libclang_rt.asan_osx_dynamic.dylib:arm64e+0x511bc)
    #1 0x104a6662c in pj_memcpy string.h:854
    #2 0x104a678d8 in pj_strncpy string_i.h:137
    #3 0x1044306c8 in pjsua_buddy_get_dlg_event_info pjsua_pres.c:354
    #4 0x1043293e8 in on_buddy_dlg_event_state pjsua_app.c:675
    #5 0x104440350 in pjsua_evsub_on_state pjsua_pres.c:1947

0x0001094166b0 is located 176 bytes inside of 512-byte region [0x000109416600,0x000109416800)
freed by thread T9 here:
    #5 0x104a32a24 in pj_pool_release pool_i.h:102
    #6 0x1044e0d74 in dlg_event_on_evsub_state dlg_event.c:422

@sauwming sauwming changed the title Implement a busy lamp field feature Implement Dialog Event subscription (client only) Jan 29, 2024
@sauwming sauwming merged commit d692a99 into pjsip:master Jan 29, 2024
@goodicus goodicus deleted the busy_lamp_field branch February 22, 2024 08:36
trengginas added a commit that referenced this pull request Dec 19, 2024
- wrong callback on event: TSX_STATE when using dialog-event subscription
- wrong method called to re-subscribe from timer callback
trengginas added a commit that referenced this pull request Dec 19, 2024
- wrong callback on event: TSX_STATE when using dialog-event subscription
- wrong method called to re-subscribe from timer callback
BarryYin pushed a commit to BarryYin/pjproject that referenced this pull request Feb 3, 2026
BarryYin pushed a commit to BarryYin/pjproject that referenced this pull request Feb 3, 2026
- wrong callback on event: TSX_STATE when using dialog-event subscription
- wrong method called to re-subscribe from timer callback
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

7 participants